{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Notebook written by [Zhedong Zheng](https://github.com/zhedongzheng)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [],
   "source": [
    "from tqdm import tqdm\n",
    "import tensorflow as tf\n",
    "import numpy as np\n",
    "import sklearn\n",
    "import pprint\n",
    "import itertools\n",
    "import os\n",
    "import sys\n",
    "\n",
    "sys.path.append(os.path.dirname(os.getcwd()))\n",
    "from data import WN18"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [],
   "source": [
    "class Config:\n",
    "    n_epochs = 30\n",
    "    batch_size = 150\n",
    "    embed_dim = 200"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [],
   "source": [
    "\"\"\"\n",
    "e: entity\n",
    "s: subject\n",
    "p: predicate\n",
    "o: object\n",
    "\"\"\"\n",
    "def glance_dict(d, n=5):\n",
    "    return dict(itertools.islice(d.items(), n))\n",
    "\n",
    "\n",
    "def read_triples(path):\n",
    "    triples = []\n",
    "    with open(path, 'rt') as f:\n",
    "        for line in f.readlines():\n",
    "            s, p, o = line.split()\n",
    "            triples += [(s.strip(), p.strip(), o.strip())]\n",
    "    return triples\n",
    "\n",
    "\n",
    "def load_triple():\n",
    "    WN18.download()\n",
    "    triples_tr = read_triples('../data/WN18/wn18/train.txt')\n",
    "    triples_va = read_triples('../data/WN18/wn18/valid.txt')\n",
    "    triples_te = read_triples('../data/WN18/wn18/test.txt')\n",
    "    triples_all = triples_tr + triples_va + triples_te\n",
    "    return triples_all, triples_tr, triples_va, triples_te\n",
    "\n",
    "\n",
    "def build_vocab(triples):\n",
    "    params = {}\n",
    "    e_set = {s for (s, p, o) in triples} | {o for (s, p, o) in triples}\n",
    "    p_set = {p for (s, p, o) in triples}\n",
    "    params['e_vocab_size'] = len(e_set)\n",
    "    params['p_vocab_size'] = len(p_set)\n",
    "    e2idx = {e: idx for idx, e in enumerate(sorted(e_set))}\n",
    "    p2idx = {p: idx for idx, p in enumerate(sorted(p_set))}\n",
    "    return e2idx, p2idx, params\n",
    "\n",
    "\n",
    "def build_multi_label(triples_tr):\n",
    "    sp2o = {}\n",
    "    for (_s, _p, _o) in triples_tr:\n",
    "        s, p, o = e2idx[_s], p2idx[_p], e2idx[_o] \n",
    "        if (s,p) not in sp2o:\n",
    "            sp2o[(s,p)] = [o]\n",
    "        else:\n",
    "            if o not in sp2o[(s,p)]:\n",
    "                sp2o[(s,p)].append(o)\n",
    "    return sp2o\n",
    "\n",
    "\n",
    "def get_y(triples_tr, e2idx, p2idx, sp2o):\n",
    "    y = []\n",
    "    for (_s, _p, _o) in triples_tr:\n",
    "        s, p, o = e2idx[_s], p2idx[_p], e2idx[_o] \n",
    "        temp = np.zeros([len(e2idx)])\n",
    "        temp[sp2o[(s,p)]] = 1.\n",
    "        y.append(temp)\n",
    "    y = np.asarray(y)\n",
    "    return y\n",
    "\n",
    "\n",
    "def next_train_batch(triples_tr, e2idx, p2idx, sp2o):\n",
    "    for i in range(0, len(triples_tr), Config.batch_size):\n",
    "        _triples_tr = triples_tr[i: i+Config.batch_size]\n",
    "        x_s = np.asarray([e2idx[s] for (s, p, o) in _triples_tr], dtype=np.int32)\n",
    "        x_p = np.asarray([p2idx[p] for (s, p, o) in _triples_tr], dtype=np.int32)\n",
    "        y = get_y(_triples_tr, e2idx, p2idx, sp2o)\n",
    "        yield (x_s, x_p, y)\n",
    "\n",
    "\n",
    "def train_input_fn(triples_tr, e2idx, p2idx, s2p2o):\n",
    "    dataset = tf.data.Dataset.from_generator(\n",
    "        lambda: next_train_batch(sklearn.utils.shuffle(triples_tr),\n",
    "                                 e2idx,\n",
    "                                 p2idx,\n",
    "                                 s2p2o),\n",
    "        (tf.int32, tf.int32, tf.float32),\n",
    "        (tf.TensorShape([None]),\n",
    "         tf.TensorShape([None]),\n",
    "         tf.TensorShape([None, len(e2idx)])))\n",
    "    iterator = dataset.make_one_shot_iterator()\n",
    "    x_s, x_p, y = iterator.get_next()\n",
    "    return {'s': x_s, 'p': x_p}, y"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [],
   "source": [
    "def o_next_batch(eval_triples,\n",
    "                 e2idx, \n",
    "                 p2idx):\n",
    "    for (s, p, o) in tqdm(eval_triples, total=len(eval_triples), ncols=70):\n",
    "        s_idx, p_idx = e2idx[s], p2idx[p]\n",
    "        yield np.atleast_1d(s_idx), np.atleast_1d(p_idx)\n",
    "\n",
    "\n",
    "def o_input_fn(eval_triples,\n",
    "               e2idx, \n",
    "               p2idx):\n",
    "    dataset = tf.data.Dataset.from_generator(\n",
    "        lambda: o_next_batch(eval_triples,\n",
    "                             e2idx, \n",
    "                             p2idx),\n",
    "        (tf.int32, tf.int32),\n",
    "        (tf.TensorShape([None,]),\n",
    "         tf.TensorShape([None,])))\n",
    "    iterator = dataset.make_one_shot_iterator()\n",
    "    s, p = iterator.get_next()\n",
    "    return {'s': s, 'p': p}\n",
    "\n",
    "\n",
    "def evaluate_rank(model,\n",
    "                  valid_triples,\n",
    "                  test_triples,\n",
    "                  all_triples,\n",
    "                  e2idx,\n",
    "                  p2idx):\n",
    "    for eval_name, eval_triples in [('test', test_triples)]:\n",
    "        _scores_o = list(model.predict(\n",
    "            lambda: o_input_fn(eval_triples,\n",
    "                               e2idx, \n",
    "                               p2idx)))\n",
    "        ScoresO = np.reshape(_scores_o, [len(eval_triples), len(e2idx)])\n",
    "        ranks_o, filtered_ranks_o = [], []\n",
    "        for ((s, p, o), scores_o) in tqdm(zip(eval_triples, ScoresO),\n",
    "                                          total=len(eval_triples),\n",
    "                                          ncols=70):\n",
    "            s_idx, p_idx, o_idx = e2idx[s], p2idx[p], e2idx[o]\n",
    "            ranks_o += [1 + np.argsort(np.argsort(- scores_o))[o_idx]]\n",
    "            filtered_scores_o = scores_o.copy()\n",
    "            rm_idx_o = [e2idx[fo] for (fs, fp, fo) in all_triples if fs == s and fp == p and fo != o]\n",
    "            filtered_scores_o[rm_idx_o] = - np.inf\n",
    "            filtered_ranks_o += [1 + np.argsort(np.argsort(- filtered_scores_o))[o_idx]]\n",
    "        for setting_name, setting_ranks in [('Raw', ranks_o), ('Filtered', filtered_ranks_o)]:\n",
    "            mean_rank = np.mean(1 / np.asarray(setting_ranks))\n",
    "            print('[{}] {} MRR: {}'.format(eval_name, setting_name, mean_rank))\n",
    "            for k in [1, 3, 5, 10]:\n",
    "                hits_at_k = np.mean(np.asarray(setting_ranks) <= k) * 100\n",
    "                print('[{}] {} Hits@{}: {}'.format(eval_name, setting_name, k, hits_at_k))"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [],
   "source": [
    "def forward(features, params):\n",
    "    e_embed = tf.get_variable('e_embed',\n",
    "                              [params['e_vocab_size'], Config.embed_dim],\n",
    "                              initializer=tf.contrib.layers.xavier_initializer())\n",
    "    p_embed = tf.get_variable('p_embed',\n",
    "                              [params['p_vocab_size'], Config.embed_dim],\n",
    "                              initializer=tf.contrib.layers.xavier_initializer())\n",
    "    \n",
    "    s = tf.nn.embedding_lookup(e_embed, features['s'])\n",
    "    p = tf.nn.embedding_lookup(p_embed, features['p'])\n",
    "    \n",
    "    logits = tf.matmul(s*p, e_embed, transpose_b=True)\n",
    "    return logits\n",
    "    \n",
    "    \n",
    "def model_fn(features, labels, mode, params):\n",
    "    logits = forward(features, params)\n",
    "    \n",
    "    if mode == tf.estimator.ModeKeys.TRAIN:\n",
    "        tf.logging.info('\\n'+pprint.pformat(tf.trainable_variables()))\n",
    "        tf.logging.info('params: %d'%count_train_params())\n",
    "        \n",
    "        loss_op = tf.reduce_sum(tf.nn.sigmoid_cross_entropy_with_logits(logits=logits,\n",
    "                                                                        labels=labels))\n",
    "        \n",
    "        train_op = tf.train.AdamOptimizer().minimize(\n",
    "            loss_op, global_step=tf.train.get_global_step())\n",
    "        \n",
    "        return tf.estimator.EstimatorSpec(mode = mode,\n",
    "                                          loss = loss_op,\n",
    "                                          train_op = train_op)\n",
    "    \n",
    "    if mode == tf.estimator.ModeKeys.PREDICT:\n",
    "        return tf.estimator.EstimatorSpec(mode, predictions = tf.sigmoid(logits))\n",
    "\n",
    "\n",
    "def count_train_params():\n",
    "    return np.sum([np.prod([d.value for d in v.get_shape()]) for v in tf.trainable_variables()])\n",
    "\n",
    "\n",
    "def prt_epoch(n_epoch):\n",
    "    print()\n",
    "    print(\"EPOCH %d\"%(n_epoch+1))\n",
    "    print()"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 6,
   "metadata": {
    "scrolled": false
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Files Already Downloaded\n",
      "INFO:tensorflow:Using default config.\n",
      "WARNING:tensorflow:Using temporary folder as model directory: /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k\n",
      "INFO:tensorflow:Using config: {'_model_dir': '/var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k', '_tf_random_seed': None, '_save_summary_steps': 100, '_save_checkpoints_steps': None, '_save_checkpoints_secs': 600, '_session_config': None, '_keep_checkpoint_max': 5, '_keep_checkpoint_every_n_hours': 10000, '_log_step_count_steps': 100, '_train_distribute': None, '_service': None, '_cluster_spec': <tensorflow.python.training.server_lib.ClusterSpec object at 0x11432a6d8>, '_task_type': 'worker', '_task_id': 0, '_global_id_in_cluster': 0, '_master': '', '_evaluation_master': '', '_is_chief': True, '_num_ps_replicas': 0, '_num_worker_replicas': 1}\n",
      "\n",
      "EPOCH 1\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 1 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 4252353.5, step = 1\n",
      "INFO:tensorflow:global_step/sec: 2.19997\n",
      "INFO:tensorflow:loss = 3433603.0, step = 101 (45.456 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25469\n",
      "INFO:tensorflow:loss = 1040215.4, step = 201 (44.352 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23782\n",
      "INFO:tensorflow:loss = 401303.2, step = 301 (44.687 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22622\n",
      "INFO:tensorflow:loss = 221720.98, step = 401 (44.919 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21716\n",
      "INFO:tensorflow:loss = 125180.1, step = 501 (45.103 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25946\n",
      "INFO:tensorflow:loss = 99627.51, step = 601 (44.258 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23361\n",
      "INFO:tensorflow:loss = 94316.195, step = 701 (44.770 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20605\n",
      "INFO:tensorflow:loss = 78883.32, step = 801 (45.330 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24562\n",
      "INFO:tensorflow:loss = 50124.133, step = 901 (44.531 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 943 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 41996.06.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-943\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 359.35it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:53<00:00, 44.15it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.0035374727540026696\n",
      "[test] Raw Hits@1: 0.1\n",
      "[test] Raw Hits@3: 0.16\n",
      "[test] Raw Hits@5: 0.48\n",
      "[test] Raw Hits@10: 1.18\n",
      "[test] Filtered MRR: 0.003537649333071381\n",
      "[test] Filtered Hits@1: 0.1\n",
      "[test] Filtered Hits@3: 0.16\n",
      "[test] Filtered Hits@5: 0.48\n",
      "[test] Filtered Hits@10: 1.18\n",
      "\n",
      "EPOCH 2\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-943\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 944 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 67589.39, step = 944\n",
      "INFO:tensorflow:global_step/sec: 2.1965\n",
      "INFO:tensorflow:loss = 60194.246, step = 1044 (45.528 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24601\n",
      "INFO:tensorflow:loss = 37528.48, step = 1144 (44.524 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23127\n",
      "INFO:tensorflow:loss = 38810.477, step = 1244 (44.818 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23866\n",
      "INFO:tensorflow:loss = 31106.299, step = 1344 (44.670 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28839\n",
      "INFO:tensorflow:loss = 35046.742, step = 1444 (43.699 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23671\n",
      "INFO:tensorflow:loss = 25449.467, step = 1544 (44.709 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23687\n",
      "INFO:tensorflow:loss = 28624.586, step = 1644 (44.705 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22775\n",
      "INFO:tensorflow:loss = 27183.81, step = 1744 (44.888 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23375\n",
      "INFO:tensorflow:loss = 19961.092, step = 1844 (44.768 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 1886 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 16617.908.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-1886\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:14<00:00, 354.65it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:52<00:00, 44.63it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.01739921274610752\n",
      "[test] Raw Hits@1: 1.26\n",
      "[test] Raw Hits@3: 1.7000000000000002\n",
      "[test] Raw Hits@5: 1.8800000000000001\n",
      "[test] Raw Hits@10: 2.36\n",
      "[test] Filtered MRR: 0.01764422971744893\n",
      "[test] Filtered Hits@1: 1.3\n",
      "[test] Filtered Hits@3: 1.7000000000000002\n",
      "[test] Filtered Hits@5: 1.9\n",
      "[test] Filtered Hits@10: 2.4\n",
      "\n",
      "EPOCH 3\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-1886\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 1887 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 25825.723, step = 1887\n",
      "INFO:tensorflow:global_step/sec: 2.36225\n",
      "INFO:tensorflow:loss = 18741.236, step = 1987 (42.334 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23295\n",
      "INFO:tensorflow:loss = 17905.85, step = 2087 (44.784 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26083\n",
      "INFO:tensorflow:loss = 20690.707, step = 2187 (44.231 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32809\n",
      "INFO:tensorflow:loss = 16674.988, step = 2287 (42.953 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27842\n",
      "INFO:tensorflow:loss = 17346.309, step = 2387 (43.890 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.33701\n",
      "INFO:tensorflow:loss = 14375.685, step = 2487 (42.791 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.3163\n",
      "INFO:tensorflow:loss = 14908.708, step = 2587 (43.170 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24449\n",
      "INFO:tensorflow:loss = 12689.087, step = 2687 (44.554 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25239\n",
      "INFO:tensorflow:loss = 14744.819, step = 2787 (44.398 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 2829 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 17595.633.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-2829\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:14<00:00, 355.70it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 44.78it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.023883266886111625\n",
      "[test] Raw Hits@1: 1.6400000000000001\n",
      "[test] Raw Hits@3: 2.44\n",
      "[test] Raw Hits@5: 2.88\n",
      "[test] Raw Hits@10: 3.64\n",
      "[test] Filtered MRR: 0.0245001569601884\n",
      "[test] Filtered Hits@1: 1.76\n",
      "[test] Filtered Hits@3: 2.44\n",
      "[test] Filtered Hits@5: 2.92\n",
      "[test] Filtered Hits@10: 3.64\n",
      "\n",
      "EPOCH 4\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-2829\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 2830 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 20338.955, step = 2830\n",
      "INFO:tensorflow:global_step/sec: 2.23781\n",
      "INFO:tensorflow:loss = 18849.307, step = 2930 (44.688 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26815\n",
      "INFO:tensorflow:loss = 12866.25, step = 3030 (44.089 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2605\n",
      "INFO:tensorflow:loss = 14045.436, step = 3130 (44.238 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2476\n",
      "INFO:tensorflow:loss = 11630.928, step = 3230 (44.493 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32245\n",
      "INFO:tensorflow:loss = 17157.793, step = 3330 (43.057 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.3173\n",
      "INFO:tensorflow:loss = 11314.562, step = 3430 (43.154 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26712\n",
      "INFO:tensorflow:loss = 9849.858, step = 3530 (44.109 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26767\n",
      "INFO:tensorflow:loss = 10884.798, step = 3630 (44.098 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29568\n",
      "INFO:tensorflow:loss = 12893.008, step = 3730 (43.560 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 3772 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 11853.169.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-3772\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 362.96it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:45<00:00, 47.25it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.038075246737390954\n",
      "[test] Raw Hits@1: 3.1199999999999997\n",
      "[test] Raw Hits@3: 3.9\n",
      "[test] Raw Hits@5: 4.4799999999999995\n",
      "[test] Raw Hits@10: 5.0\n",
      "[test] Filtered MRR: 0.03888596692061227\n",
      "[test] Filtered Hits@1: 3.26\n",
      "[test] Filtered Hits@3: 3.92\n",
      "[test] Filtered Hits@5: 4.52\n",
      "[test] Filtered Hits@10: 5.0200000000000005\n",
      "\n",
      "EPOCH 5\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-3772\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 3773 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 9901.346, step = 3773\n",
      "INFO:tensorflow:global_step/sec: 2.30363\n",
      "INFO:tensorflow:loss = 13824.256, step = 3873 (43.411 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.36041\n",
      "INFO:tensorflow:loss = 13038.432, step = 3973 (42.366 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.33411\n",
      "INFO:tensorflow:loss = 12561.514, step = 4073 (42.843 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31657\n",
      "INFO:tensorflow:loss = 13731.277, step = 4173 (43.167 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.40637\n",
      "INFO:tensorflow:loss = 9891.798, step = 4273 (41.556 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.35943\n",
      "INFO:tensorflow:loss = 12074.177, step = 4373 (42.383 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.40601\n",
      "INFO:tensorflow:loss = 9421.547, step = 4473 (41.562 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.36856\n",
      "INFO:tensorflow:loss = 8047.691, step = 4573 (42.220 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55081\n",
      "INFO:tensorflow:loss = 8612.498, step = 4673 (39.203 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 4715 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 6918.998.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-4715\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 368.69it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:44<00:00, 48.05it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.04380451613964493\n",
      "[test] Raw Hits@1: 3.5999999999999996\n",
      "[test] Raw Hits@3: 4.64\n",
      "[test] Raw Hits@5: 5.12\n",
      "[test] Raw Hits@10: 5.62\n",
      "[test] Filtered MRR: 0.04459733584966539\n",
      "[test] Filtered Hits@1: 3.7199999999999998\n",
      "[test] Filtered Hits@3: 4.7\n",
      "[test] Filtered Hits@5: 5.140000000000001\n",
      "[test] Filtered Hits@10: 5.64\n",
      "\n",
      "EPOCH 6\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-4715\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 4716 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 8474.805, step = 4716\n",
      "INFO:tensorflow:global_step/sec: 2.54713\n",
      "INFO:tensorflow:loss = 9941.367, step = 4816 (39.261 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5578\n",
      "INFO:tensorflow:loss = 7176.0474, step = 4916 (39.096 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55701\n",
      "INFO:tensorflow:loss = 8248.831, step = 5016 (39.108 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56033\n",
      "INFO:tensorflow:loss = 10336.456, step = 5116 (39.058 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.54639\n",
      "INFO:tensorflow:loss = 8217.188, step = 5216 (39.271 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55722\n",
      "INFO:tensorflow:loss = 7784.993, step = 5316 (39.105 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55451\n",
      "INFO:tensorflow:loss = 7605.867, step = 5416 (39.146 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.54843\n",
      "INFO:tensorflow:loss = 6703.248, step = 5516 (39.240 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55547\n",
      "INFO:tensorflow:loss = 7703.133, step = 5616 (39.132 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 5658 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 7321.847.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-5658\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 371.96it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:43<00:00, 48.49it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.05376594211245947\n",
      "[test] Raw Hits@1: 4.58\n",
      "[test] Raw Hits@3: 5.800000000000001\n",
      "[test] Raw Hits@5: 6.08\n",
      "[test] Raw Hits@10: 6.419999999999999\n",
      "[test] Filtered MRR: 0.054676172115235226\n",
      "[test] Filtered Hits@1: 4.72\n",
      "[test] Filtered Hits@3: 5.800000000000001\n",
      "[test] Filtered Hits@5: 6.1\n",
      "[test] Filtered Hits@10: 6.4399999999999995\n",
      "\n",
      "EPOCH 7\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-5658\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 5659 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 6465.6445, step = 5659\n",
      "INFO:tensorflow:global_step/sec: 2.54557\n",
      "INFO:tensorflow:loss = 7312.3696, step = 5759 (39.285 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5584\n",
      "INFO:tensorflow:loss = 7309.261, step = 5859 (39.087 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56068\n",
      "INFO:tensorflow:loss = 7802.197, step = 5959 (39.052 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55614\n",
      "INFO:tensorflow:loss = 7185.715, step = 6059 (39.122 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55518\n",
      "INFO:tensorflow:loss = 6096.144, step = 6159 (39.136 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55069\n",
      "INFO:tensorflow:loss = 5937.864, step = 6259 (39.205 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55501\n",
      "INFO:tensorflow:loss = 6821.8633, step = 6359 (39.139 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55397\n",
      "INFO:tensorflow:loss = 6914.038, step = 6459 (39.155 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55783\n",
      "INFO:tensorflow:loss = 6408.978, step = 6559 (39.096 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 6601 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 4667.089.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-6601\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 372.90it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:43<00:00, 48.49it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.06261251350013179\n",
      "[test] Raw Hits@1: 5.42\n",
      "[test] Raw Hits@3: 6.619999999999999\n",
      "[test] Raw Hits@5: 6.84\n",
      "[test] Raw Hits@10: 7.66\n",
      "[test] Filtered MRR: 0.06382328319715808\n",
      "[test] Filtered Hits@1: 5.6000000000000005\n",
      "[test] Filtered Hits@3: 6.64\n",
      "[test] Filtered Hits@5: 6.859999999999999\n",
      "[test] Filtered Hits@10: 7.76\n",
      "\n",
      "EPOCH 8\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-6601\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 6602 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 6644.6484, step = 6602\n",
      "INFO:tensorflow:global_step/sec: 2.54891\n",
      "INFO:tensorflow:loss = 5159.2266, step = 6702 (39.234 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55535\n",
      "INFO:tensorflow:loss = 5804.966, step = 6802 (39.134 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5574\n",
      "INFO:tensorflow:loss = 6238.9565, step = 6902 (39.101 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55599\n",
      "INFO:tensorflow:loss = 4635.219, step = 7002 (39.124 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55228\n",
      "INFO:tensorflow:loss = 5274.3066, step = 7102 (39.180 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55272\n",
      "INFO:tensorflow:loss = 5745.31, step = 7202 (39.174 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55798\n",
      "INFO:tensorflow:loss = 5736.845, step = 7302 (39.093 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56093\n",
      "INFO:tensorflow:loss = 6198.398, step = 7402 (39.049 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55506\n",
      "INFO:tensorflow:loss = 4662.3555, step = 7502 (39.138 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 7544 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 5624.9785.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-7544\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 373.91it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:40<00:00, 49.90it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.07276392436308333\n",
      "[test] Raw Hits@1: 6.239999999999999\n",
      "[test] Raw Hits@3: 7.720000000000001\n",
      "[test] Raw Hits@5: 8.219999999999999\n",
      "[test] Raw Hits@10: 9.04\n",
      "[test] Filtered MRR: 0.074171864129504\n",
      "[test] Filtered Hits@1: 6.4\n",
      "[test] Filtered Hits@3: 7.8\n",
      "[test] Filtered Hits@5: 8.3\n",
      "[test] Filtered Hits@10: 9.180000000000001\n",
      "\n",
      "EPOCH 9\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-7544\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 7545 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 5583.374, step = 7545\n",
      "INFO:tensorflow:global_step/sec: 2.55044\n",
      "INFO:tensorflow:loss = 5209.782, step = 7645 (39.210 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56699\n",
      "INFO:tensorflow:loss = 5595.8945, step = 7745 (38.956 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55962\n",
      "INFO:tensorflow:loss = 4550.542, step = 7845 (39.068 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55653\n",
      "INFO:tensorflow:loss = 4832.183, step = 7945 (39.116 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55231\n",
      "INFO:tensorflow:loss = 5310.118, step = 8045 (39.180 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56008\n",
      "INFO:tensorflow:loss = 4648.8965, step = 8145 (39.061 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55722\n",
      "INFO:tensorflow:loss = 3970.9746, step = 8245 (39.105 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56044\n",
      "INFO:tensorflow:loss = 4698.495, step = 8345 (39.056 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55662\n",
      "INFO:tensorflow:loss = 4761.966, step = 8445 (39.114 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 8487 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 4806.588.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-8487\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 375.34it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:39<00:00, 50.06it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.08630966605472468\n",
      "[test] Raw Hits@1: 7.28\n",
      "[test] Raw Hits@3: 9.34\n",
      "[test] Raw Hits@5: 9.879999999999999\n",
      "[test] Raw Hits@10: 10.76\n",
      "[test] Filtered MRR: 0.08763431829792782\n",
      "[test] Filtered Hits@1: 7.42\n",
      "[test] Filtered Hits@3: 9.4\n",
      "[test] Filtered Hits@5: 9.959999999999999\n",
      "[test] Filtered Hits@10: 10.94\n",
      "\n",
      "EPOCH 10\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-8487\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 8488 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 4975.2305, step = 8488\n",
      "INFO:tensorflow:global_step/sec: 2.549\n",
      "INFO:tensorflow:loss = 4587.0415, step = 8588 (39.232 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55251\n",
      "INFO:tensorflow:loss = 4139.999, step = 8688 (39.178 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55992\n",
      "INFO:tensorflow:loss = 4477.191, step = 8788 (39.063 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55533\n",
      "INFO:tensorflow:loss = 4044.339, step = 8888 (39.134 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5561\n",
      "INFO:tensorflow:loss = 4925.982, step = 8988 (39.122 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55722\n",
      "INFO:tensorflow:loss = 4704.081, step = 9088 (39.105 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55746\n",
      "INFO:tensorflow:loss = 4380.9517, step = 9188 (39.101 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55413\n",
      "INFO:tensorflow:loss = 3988.7012, step = 9288 (39.152 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55809\n",
      "INFO:tensorflow:loss = 4147.1577, step = 9388 (39.092 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 9430 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 4068.4746.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-9430\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 375.51it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:40<00:00, 49.87it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.10367043477997784\n",
      "[test] Raw Hits@1: 8.88\n",
      "[test] Raw Hits@3: 11.0\n",
      "[test] Raw Hits@5: 11.74\n",
      "[test] Raw Hits@10: 12.68\n",
      "[test] Filtered MRR: 0.10558263192586365\n",
      "[test] Filtered Hits@1: 9.1\n",
      "[test] Filtered Hits@3: 11.08\n",
      "[test] Filtered Hits@5: 11.88\n",
      "[test] Filtered Hits@10: 12.9\n",
      "\n",
      "EPOCH 11\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-9430\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 9431 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 4273.4043, step = 9431\n",
      "INFO:tensorflow:global_step/sec: 2.55313\n",
      "INFO:tensorflow:loss = 4035.2603, step = 9531 (39.169 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56062\n",
      "INFO:tensorflow:loss = 3784.7722, step = 9631 (39.053 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55082\n",
      "INFO:tensorflow:loss = 4046.516, step = 9731 (39.203 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55133\n",
      "INFO:tensorflow:loss = 3762.0857, step = 9831 (39.195 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55713\n",
      "INFO:tensorflow:loss = 4164.4326, step = 9931 (39.106 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5587\n",
      "INFO:tensorflow:loss = 3752.167, step = 10031 (39.083 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55585\n",
      "INFO:tensorflow:loss = 3529.083, step = 10131 (39.126 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55626\n",
      "INFO:tensorflow:loss = 3008.2168, step = 10231 (39.120 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55931\n",
      "INFO:tensorflow:loss = 3570.4744, step = 10331 (39.073 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 10373 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 3209.9414.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-10373\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 376.27it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:39<00:00, 50.02it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.12806008171550498\n",
      "[test] Raw Hits@1: 11.08\n",
      "[test] Raw Hits@3: 13.5\n",
      "[test] Raw Hits@5: 14.360000000000001\n",
      "[test] Raw Hits@10: 15.58\n",
      "[test] Filtered MRR: 0.1312529619955511\n",
      "[test] Filtered Hits@1: 11.379999999999999\n",
      "[test] Filtered Hits@3: 13.700000000000001\n",
      "[test] Filtered Hits@5: 14.66\n",
      "[test] Filtered Hits@10: 16.14\n",
      "\n",
      "EPOCH 12\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-10373\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 10374 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 3149.8394, step = 10374\n",
      "INFO:tensorflow:global_step/sec: 2.55468\n",
      "INFO:tensorflow:loss = 3115.2493, step = 10474 (39.145 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55676\n",
      "INFO:tensorflow:loss = 3332.2559, step = 10574 (39.112 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56096\n",
      "INFO:tensorflow:loss = 2930.2903, step = 10674 (39.048 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55779\n",
      "INFO:tensorflow:loss = 2692.7634, step = 10774 (39.096 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55423\n",
      "INFO:tensorflow:loss = 3084.9387, step = 10874 (39.150 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55499\n",
      "INFO:tensorflow:loss = 2803.0117, step = 10974 (39.139 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55238\n",
      "INFO:tensorflow:loss = 2873.0403, step = 11074 (39.179 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55853\n",
      "INFO:tensorflow:loss = 2749.7148, step = 11174 (39.085 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55347\n",
      "INFO:tensorflow:loss = 3102.2412, step = 11274 (39.162 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 11316 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 2868.4482.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-11316\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 375.90it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:40<00:00, 49.85it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.15848225613513636\n",
      "[test] Raw Hits@1: 13.639999999999999\n",
      "[test] Raw Hits@3: 16.900000000000002\n",
      "[test] Raw Hits@5: 17.740000000000002\n",
      "[test] Raw Hits@10: 19.54\n",
      "[test] Filtered MRR: 0.16330366624677642\n",
      "[test] Filtered Hits@1: 14.02\n",
      "[test] Filtered Hits@3: 17.26\n",
      "[test] Filtered Hits@5: 18.16\n",
      "[test] Filtered Hits@10: 20.34\n",
      "\n",
      "EPOCH 13\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-11316\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 11317 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 2533.4922, step = 11317\n",
      "INFO:tensorflow:global_step/sec: 2.5496\n",
      "INFO:tensorflow:loss = 2646.5251, step = 11417 (39.223 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55893\n",
      "INFO:tensorflow:loss = 2491.1338, step = 11517 (39.080 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55759\n",
      "INFO:tensorflow:loss = 2647.3496, step = 11617 (39.099 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55629\n",
      "INFO:tensorflow:loss = 2402.6462, step = 11717 (39.119 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5535\n",
      "INFO:tensorflow:loss = 2557.0354, step = 11817 (39.162 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55911\n",
      "INFO:tensorflow:loss = 2540.144, step = 11917 (39.076 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55842\n",
      "INFO:tensorflow:loss = 2321.7375, step = 12017 (39.087 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55989\n",
      "INFO:tensorflow:loss = 2641.566, step = 12117 (39.064 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.5309\n",
      "INFO:tensorflow:loss = 2460.5298, step = 12217 (39.512 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 12259 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 2259.2266.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-12259\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 375.25it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:40<00:00, 49.95it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.19875376804103795\n",
      "[test] Raw Hits@1: 17.0\n",
      "[test] Raw Hits@3: 21.36\n",
      "[test] Raw Hits@5: 22.759999999999998\n",
      "[test] Raw Hits@10: 24.5\n",
      "[test] Filtered MRR: 0.20614882486850183\n",
      "[test] Filtered Hits@1: 17.72\n",
      "[test] Filtered Hits@3: 22.12\n",
      "[test] Filtered Hits@5: 23.44\n",
      "[test] Filtered Hits@10: 25.3\n",
      "\n",
      "EPOCH 14\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-12259\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 12260 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 2398.1628, step = 12260\n",
      "INFO:tensorflow:global_step/sec: 2.54898\n",
      "INFO:tensorflow:loss = 1776.5181, step = 12360 (39.232 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55403\n",
      "INFO:tensorflow:loss = 2212.604, step = 12460 (39.155 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55831\n",
      "INFO:tensorflow:loss = 2116.8225, step = 12560 (39.088 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55806\n",
      "INFO:tensorflow:loss = 1818.404, step = 12660 (39.092 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55783\n",
      "INFO:tensorflow:loss = 2169.241, step = 12760 (39.095 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55606\n",
      "INFO:tensorflow:loss = 2236.4648, step = 12860 (39.123 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.56054\n",
      "INFO:tensorflow:loss = 1995.6262, step = 12960 (39.054 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55568\n",
      "INFO:tensorflow:loss = 1849.6245, step = 13060 (39.129 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.55714\n",
      "INFO:tensorflow:loss = 1648.5114, step = 13160 (39.106 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 13202 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 1868.7408.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-13202\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 375.34it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:47<00:00, 46.31it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.2384586786275213\n",
      "[test] Raw Hits@1: 20.96\n",
      "[test] Raw Hits@3: 25.44\n",
      "[test] Raw Hits@5: 26.619999999999997\n",
      "[test] Raw Hits@10: 28.16\n",
      "[test] Filtered MRR: 0.2507330080551267\n",
      "[test] Filtered Hits@1: 22.3\n",
      "[test] Filtered Hits@3: 26.44\n",
      "[test] Filtered Hits@5: 27.560000000000002\n",
      "[test] Filtered Hits@10: 29.38\n",
      "\n",
      "EPOCH 15\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-13202\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 13203 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 1774.2357, step = 13203\n",
      "INFO:tensorflow:global_step/sec: 2.50815\n",
      "INFO:tensorflow:loss = 1531.2141, step = 13303 (39.871 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.52191\n",
      "INFO:tensorflow:loss = 1723.073, step = 13403 (39.653 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.40653\n",
      "INFO:tensorflow:loss = 1588.726, step = 13503 (41.554 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23312\n",
      "INFO:tensorflow:loss = 1826.0823, step = 13603 (44.780 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29323\n",
      "INFO:tensorflow:loss = 1567.0006, step = 13703 (43.607 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22233\n",
      "INFO:tensorflow:loss = 1689.666, step = 13803 (44.998 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.34214\n",
      "INFO:tensorflow:loss = 1538.5123, step = 13903 (42.696 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26196\n",
      "INFO:tensorflow:loss = 1436.7605, step = 14003 (44.209 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24861\n",
      "INFO:tensorflow:loss = 1404.5249, step = 14103 (44.472 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 14145 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 1294.2357.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-14145\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 365.01it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 45.00it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.27228822301216793\n",
      "[test] Raw Hits@1: 23.68\n",
      "[test] Raw Hits@3: 29.060000000000002\n",
      "[test] Raw Hits@5: 30.56\n",
      "[test] Raw Hits@10: 32.879999999999995\n",
      "[test] Filtered MRR: 0.2904278282733516\n",
      "[test] Filtered Hits@1: 25.64\n",
      "[test] Filtered Hits@3: 30.599999999999998\n",
      "[test] Filtered Hits@5: 32.24\n",
      "[test] Filtered Hits@10: 34.88\n",
      "\n",
      "EPOCH 16\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-14145\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 14146 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 1275.8872, step = 14146\n",
      "INFO:tensorflow:global_step/sec: 2.45047\n",
      "INFO:tensorflow:loss = 1319.7583, step = 14246 (40.810 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.53414\n",
      "INFO:tensorflow:loss = 1386.8082, step = 14346 (39.461 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.4319\n",
      "INFO:tensorflow:loss = 1235.4552, step = 14446 (41.120 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.18615\n",
      "INFO:tensorflow:loss = 1108.2678, step = 14546 (45.742 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25485\n",
      "INFO:tensorflow:loss = 1219.5662, step = 14646 (44.349 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.3164\n",
      "INFO:tensorflow:loss = 1152.2842, step = 14746 (43.170 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31553\n",
      "INFO:tensorflow:loss = 974.57214, step = 14846 (43.187 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31812\n",
      "INFO:tensorflow:loss = 1122.0969, step = 14946 (43.138 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31181\n",
      "INFO:tensorflow:loss = 993.506, step = 15046 (43.257 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 15088 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 1027.3394.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-15088\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 365.69it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 44.87it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.30323327505563563\n",
      "[test] Raw Hits@1: 26.02\n",
      "[test] Raw Hits@3: 32.379999999999995\n",
      "[test] Raw Hits@5: 34.68\n",
      "[test] Raw Hits@10: 38.06\n",
      "[test] Filtered MRR: 0.33277315668852564\n",
      "[test] Filtered Hits@1: 29.32\n",
      "[test] Filtered Hits@3: 34.699999999999996\n",
      "[test] Filtered Hits@5: 37.26\n",
      "[test] Filtered Hits@10: 40.739999999999995\n",
      "\n",
      "EPOCH 17\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-15088\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 15089 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 962.48584, step = 15089\n",
      "INFO:tensorflow:global_step/sec: 2.32102\n",
      "INFO:tensorflow:loss = 910.7654, step = 15189 (43.086 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.3214\n",
      "INFO:tensorflow:loss = 883.1948, step = 15289 (43.078 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32555\n",
      "INFO:tensorflow:loss = 1090.8035, step = 15389 (43.000 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32394\n",
      "INFO:tensorflow:loss = 959.30255, step = 15489 (43.030 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32362\n",
      "INFO:tensorflow:loss = 876.2322, step = 15589 (43.036 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32112\n",
      "INFO:tensorflow:loss = 864.32605, step = 15689 (43.083 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32537\n",
      "INFO:tensorflow:loss = 836.07086, step = 15789 (43.003 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31598\n",
      "INFO:tensorflow:loss = 818.7061, step = 15889 (43.179 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31016\n",
      "INFO:tensorflow:loss = 703.4842, step = 15989 (43.287 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 16031 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 713.69916.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-16031\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 366.26it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:50<00:00, 45.12it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.3309470505465643\n",
      "[test] Raw Hits@1: 27.66\n",
      "[test] Raw Hits@3: 35.88\n",
      "[test] Raw Hits@5: 39.14\n",
      "[test] Raw Hits@10: 42.66\n",
      "[test] Filtered MRR: 0.37407030409031583\n",
      "[test] Filtered Hits@1: 32.58\n",
      "[test] Filtered Hits@3: 39.34\n",
      "[test] Filtered Hits@5: 42.58\n",
      "[test] Filtered Hits@10: 46.52\n",
      "\n",
      "EPOCH 18\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-16031\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 16032 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 725.53284, step = 16032\n",
      "INFO:tensorflow:global_step/sec: 2.31108\n",
      "INFO:tensorflow:loss = 733.4353, step = 16132 (43.271 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32796\n",
      "INFO:tensorflow:loss = 667.1195, step = 16232 (42.956 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.34014\n",
      "INFO:tensorflow:loss = 577.78503, step = 16332 (42.733 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22902\n",
      "INFO:tensorflow:loss = 545.7968, step = 16432 (44.864 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28753\n",
      "INFO:tensorflow:loss = 621.3459, step = 16532 (43.714 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29001\n",
      "INFO:tensorflow:loss = 675.7483, step = 16632 (43.668 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32599\n",
      "INFO:tensorflow:loss = 679.08734, step = 16732 (42.993 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31162\n",
      "INFO:tensorflow:loss = 608.6661, step = 16832 (43.260 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28519\n",
      "INFO:tensorflow:loss = 683.3028, step = 16932 (43.760 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 16974 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 492.2743.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-16974\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 372.50it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 44.93it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.35848612460277607\n",
      "[test] Raw Hits@1: 29.4\n",
      "[test] Raw Hits@3: 39.1\n",
      "[test] Raw Hits@5: 43.08\n",
      "[test] Raw Hits@10: 47.54\n",
      "[test] Filtered MRR: 0.42088467277288527\n",
      "[test] Filtered Hits@1: 36.58\n",
      "[test] Filtered Hits@3: 44.6\n",
      "[test] Filtered Hits@5: 48.3\n",
      "[test] Filtered Hits@10: 52.64\n",
      "\n",
      "EPOCH 19\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-16974\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 16975 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 471.39337, step = 16975\n",
      "INFO:tensorflow:global_step/sec: 2.34618\n",
      "INFO:tensorflow:loss = 553.50806, step = 17075 (42.624 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.30172\n",
      "INFO:tensorflow:loss = 460.6952, step = 17175 (43.446 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.30708\n",
      "INFO:tensorflow:loss = 509.01013, step = 17275 (43.345 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.15281\n",
      "INFO:tensorflow:loss = 733.3351, step = 17375 (46.451 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.33041\n",
      "INFO:tensorflow:loss = 475.55698, step = 17475 (42.911 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.3677\n",
      "INFO:tensorflow:loss = 484.22687, step = 17575 (42.235 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2897\n",
      "INFO:tensorflow:loss = 397.81635, step = 17675 (43.674 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.18418\n",
      "INFO:tensorflow:loss = 418.59662, step = 17775 (45.784 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.30774\n",
      "INFO:tensorflow:loss = 416.59232, step = 17875 (43.332 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 17917 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 544.1855.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-17917\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 359.48it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:50<00:00, 45.07it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.3826745603298423\n",
      "[test] Raw Hits@1: 30.72\n",
      "[test] Raw Hits@3: 41.959999999999994\n",
      "[test] Raw Hits@5: 47.04\n",
      "[test] Raw Hits@10: 52.54\n",
      "[test] Filtered MRR: 0.4677128430138215\n",
      "[test] Filtered Hits@1: 40.300000000000004\n",
      "[test] Filtered Hits@3: 50.019999999999996\n",
      "[test] Filtered Hits@5: 54.459999999999994\n",
      "[test] Filtered Hits@10: 59.56\n",
      "\n",
      "EPOCH 20\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-17917\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 17918 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 448.8286, step = 17918\n",
      "INFO:tensorflow:global_step/sec: 2.32172\n",
      "INFO:tensorflow:loss = 379.91058, step = 18018 (43.073 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29069\n",
      "INFO:tensorflow:loss = 419.72992, step = 18118 (43.655 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26404\n",
      "INFO:tensorflow:loss = 363.76962, step = 18218 (44.169 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25784\n",
      "INFO:tensorflow:loss = 465.05307, step = 18318 (44.290 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.41452\n",
      "INFO:tensorflow:loss = 382.57776, step = 18418 (41.416 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.31389\n",
      "INFO:tensorflow:loss = 330.43713, step = 18518 (43.217 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27214\n",
      "INFO:tensorflow:loss = 356.3374, step = 18618 (44.012 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25143\n",
      "INFO:tensorflow:loss = 468.2586, step = 18718 (44.415 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29785\n",
      "INFO:tensorflow:loss = 339.77887, step = 18818 (43.519 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 18860 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 339.532.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-18860\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 365.26it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 44.74it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.40682575656069253\n",
      "[test] Raw Hits@1: 31.56\n",
      "[test] Raw Hits@3: 45.18\n",
      "[test] Raw Hits@5: 51.739999999999995\n",
      "[test] Raw Hits@10: 58.14\n",
      "[test] Filtered MRR: 0.5135765007616337\n",
      "[test] Filtered Hits@1: 43.14\n",
      "[test] Filtered Hits@3: 55.96\n",
      "[test] Filtered Hits@5: 61.660000000000004\n",
      "[test] Filtered Hits@10: 66.8\n",
      "\n",
      "EPOCH 21\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-18860\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 18861 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 340.0529, step = 18861\n",
      "INFO:tensorflow:global_step/sec: 2.2284\n",
      "INFO:tensorflow:loss = 282.82123, step = 18961 (44.877 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27885\n",
      "INFO:tensorflow:loss = 299.00128, step = 19061 (43.882 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.47674\n",
      "INFO:tensorflow:loss = 334.06506, step = 19161 (40.376 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.30278\n",
      "INFO:tensorflow:loss = 346.6664, step = 19261 (43.426 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27264\n",
      "INFO:tensorflow:loss = 299.4132, step = 19361 (44.001 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.44059\n",
      "INFO:tensorflow:loss = 314.42163, step = 19461 (40.974 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28666\n",
      "INFO:tensorflow:loss = 452.38623, step = 19561 (43.732 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26235\n",
      "INFO:tensorflow:loss = 361.1734, step = 19661 (44.202 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23901\n",
      "INFO:tensorflow:loss = 404.00513, step = 19761 (44.664 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 19803 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 288.5225.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-19803\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:14<00:00, 349.84it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:52<00:00, 44.26it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.42923260670797464\n",
      "[test] Raw Hits@1: 32.04\n",
      "[test] Raw Hits@3: 48.96\n",
      "[test] Raw Hits@5: 56.74\n",
      "[test] Raw Hits@10: 64.36\n",
      "[test] Filtered MRR: 0.5674097017182648\n",
      "[test] Filtered Hits@1: 46.82\n",
      "[test] Filtered Hits@3: 63.88\n",
      "[test] Filtered Hits@5: 69.16\n",
      "[test] Filtered Hits@10: 74.5\n",
      "\n",
      "EPOCH 22\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-19803\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 19804 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 254.1815, step = 19804\n",
      "INFO:tensorflow:global_step/sec: 2.21411\n",
      "INFO:tensorflow:loss = 259.21906, step = 19904 (45.166 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24415\n",
      "INFO:tensorflow:loss = 345.26642, step = 20004 (44.560 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21139\n",
      "INFO:tensorflow:loss = 289.30548, step = 20104 (45.221 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.18663\n",
      "INFO:tensorflow:loss = 293.90277, step = 20204 (45.733 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.30814\n",
      "INFO:tensorflow:loss = 245.14906, step = 20304 (43.324 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29957\n",
      "INFO:tensorflow:loss = 268.27448, step = 20404 (43.487 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.35339\n",
      "INFO:tensorflow:loss = 301.14813, step = 20504 (42.492 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24122\n",
      "INFO:tensorflow:loss = 272.03888, step = 20604 (44.619 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28509\n",
      "INFO:tensorflow:loss = 346.81967, step = 20704 (43.762 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 20746 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 312.4972.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-20746\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 362.02it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:47<00:00, 46.38it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4485230556457018\n",
      "[test] Raw Hits@1: 32.62\n",
      "[test] Raw Hits@3: 51.88\n",
      "[test] Raw Hits@5: 60.84\n",
      "[test] Raw Hits@10: 68.92\n",
      "[test] Filtered MRR: 0.6100398137674259\n",
      "[test] Filtered Hits@1: 49.68\n",
      "[test] Filtered Hits@3: 69.88\n",
      "[test] Filtered Hits@5: 75.28\n",
      "[test] Filtered Hits@10: 79.64\n",
      "\n",
      "EPOCH 23\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-20746\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 20747 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 590.8421, step = 20747\n",
      "INFO:tensorflow:global_step/sec: 2.35016\n",
      "INFO:tensorflow:loss = 230.31398, step = 20847 (42.552 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28735\n",
      "INFO:tensorflow:loss = 294.0328, step = 20947 (43.718 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29258\n",
      "INFO:tensorflow:loss = 305.73688, step = 21047 (43.619 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.18038\n",
      "INFO:tensorflow:loss = 226.95836, step = 21147 (45.863 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.17462\n",
      "INFO:tensorflow:loss = 205.44217, step = 21247 (45.985 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22152\n",
      "INFO:tensorflow:loss = 262.408, step = 21347 (45.014 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2117\n",
      "INFO:tensorflow:loss = 239.77704, step = 21447 (45.214 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.28155\n",
      "INFO:tensorflow:loss = 329.81973, step = 21547 (43.830 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.16085\n",
      "INFO:tensorflow:loss = 304.80588, step = 21647 (46.278 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 21689 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 256.65073.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-21689\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:15<00:00, 326.76it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:52<00:00, 44.57it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4641197199045606\n",
      "[test] Raw Hits@1: 33.22\n",
      "[test] Raw Hits@3: 54.67999999999999\n",
      "[test] Raw Hits@5: 63.92\n",
      "[test] Raw Hits@10: 71.94\n",
      "[test] Filtered MRR: 0.642657376102123\n",
      "[test] Filtered Hits@1: 51.72\n",
      "[test] Filtered Hits@3: 75.06\n",
      "[test] Filtered Hits@5: 79.80000000000001\n",
      "[test] Filtered Hits@10: 83.02000000000001\n",
      "\n",
      "EPOCH 24\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-21689\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 21690 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 181.33887, step = 21690\n",
      "INFO:tensorflow:global_step/sec: 2.24105\n",
      "INFO:tensorflow:loss = 214.1413, step = 21790 (44.624 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20925\n",
      "INFO:tensorflow:loss = 275.11008, step = 21890 (45.264 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.16747\n",
      "INFO:tensorflow:loss = 254.17976, step = 21990 (46.138 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21198\n",
      "INFO:tensorflow:loss = 190.70674, step = 22090 (45.209 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20842\n",
      "INFO:tensorflow:loss = 250.60146, step = 22190 (45.280 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27654\n",
      "INFO:tensorflow:loss = 273.4973, step = 22290 (43.926 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23385\n",
      "INFO:tensorflow:loss = 243.63263, step = 22390 (44.766 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27914\n",
      "INFO:tensorflow:loss = 235.88245, step = 22490 (43.876 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20402\n",
      "INFO:tensorflow:loss = 212.87134, step = 22590 (45.371 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 22632 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 287.9246.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-22632\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:15<00:00, 330.43it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:52<00:00, 44.28it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4730586737688974\n",
      "[test] Raw Hits@1: 33.4\n",
      "[test] Raw Hits@3: 56.120000000000005\n",
      "[test] Raw Hits@5: 65.72\n",
      "[test] Raw Hits@10: 73.83999999999999\n",
      "[test] Filtered MRR: 0.6669021167775986\n",
      "[test] Filtered Hits@1: 53.400000000000006\n",
      "[test] Filtered Hits@3: 78.68\n",
      "[test] Filtered Hits@5: 82.58\n",
      "[test] Filtered Hits@10: 85.26\n",
      "\n",
      "EPOCH 25\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-22632\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 22633 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 210.26286, step = 22633\n",
      "INFO:tensorflow:global_step/sec: 2.12768\n",
      "INFO:tensorflow:loss = 250.11258, step = 22733 (47.001 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.10986\n",
      "INFO:tensorflow:loss = 237.6278, step = 22833 (47.396 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29279\n",
      "INFO:tensorflow:loss = 225.59851, step = 22933 (43.615 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22338\n",
      "INFO:tensorflow:loss = 217.74202, step = 23033 (44.976 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29858\n",
      "INFO:tensorflow:loss = 260.53262, step = 23133 (43.505 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22268\n",
      "INFO:tensorflow:loss = 267.002, step = 23233 (44.991 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22516\n",
      "INFO:tensorflow:loss = 239.4503, step = 23333 (44.941 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26092\n",
      "INFO:tensorflow:loss = 267.06693, step = 23433 (44.230 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23911\n",
      "INFO:tensorflow:loss = 230.16632, step = 23533 (44.661 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 23575 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 245.75937.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-23575\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 358.12it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:50<00:00, 45.38it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.47810137546089115\n",
      "[test] Raw Hits@1: 33.42\n",
      "[test] Raw Hits@3: 57.14\n",
      "[test] Raw Hits@5: 67.12\n",
      "[test] Raw Hits@10: 75.28\n",
      "[test] Filtered MRR: 0.6766707360502476\n",
      "[test] Filtered Hits@1: 53.66\n",
      "[test] Filtered Hits@3: 80.38\n",
      "[test] Filtered Hits@5: 84.26\n",
      "[test] Filtered Hits@10: 87.0\n",
      "\n",
      "EPOCH 26\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-23575\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 23576 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 207.56778, step = 23576\n",
      "INFO:tensorflow:global_step/sec: 2.28774\n",
      "INFO:tensorflow:loss = 221.13596, step = 23676 (43.712 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2569\n",
      "INFO:tensorflow:loss = 253.97774, step = 23776 (44.309 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24821\n",
      "INFO:tensorflow:loss = 209.77666, step = 23876 (44.480 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.25925\n",
      "INFO:tensorflow:loss = 293.62534, step = 23976 (44.262 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21578\n",
      "INFO:tensorflow:loss = 213.4528, step = 24076 (45.131 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24158\n",
      "INFO:tensorflow:loss = 218.35457, step = 24176 (44.611 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21379\n",
      "INFO:tensorflow:loss = 288.70175, step = 24276 (45.173 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.36191\n",
      "INFO:tensorflow:loss = 229.78816, step = 24376 (42.337 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.29065\n",
      "INFO:tensorflow:loss = 291.29037, step = 24476 (43.656 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 24518 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 271.31808.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-24518\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 358.01it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:50<00:00, 45.31it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4815701486271466\n",
      "[test] Raw Hits@1: 33.54\n",
      "[test] Raw Hits@3: 57.620000000000005\n",
      "[test] Raw Hits@5: 67.72\n",
      "[test] Raw Hits@10: 76.12\n",
      "[test] Filtered MRR: 0.6850640385173797\n",
      "[test] Filtered Hits@1: 54.04\n",
      "[test] Filtered Hits@3: 82.0\n",
      "[test] Filtered Hits@5: 85.42\n",
      "[test] Filtered Hits@10: 87.92\n",
      "\n",
      "EPOCH 27\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-24518\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 24519 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 192.84949, step = 24519\n",
      "INFO:tensorflow:global_step/sec: 2.23746\n",
      "INFO:tensorflow:loss = 196.32744, step = 24619 (44.695 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21634\n",
      "INFO:tensorflow:loss = 179.4172, step = 24719 (45.121 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.2455\n",
      "INFO:tensorflow:loss = 231.46628, step = 24819 (44.533 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26305\n",
      "INFO:tensorflow:loss = 187.31877, step = 24919 (44.188 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.16239\n",
      "INFO:tensorflow:loss = 247.97885, step = 25019 (46.246 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.19205\n",
      "INFO:tensorflow:loss = 279.9972, step = 25119 (45.619 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20233\n",
      "INFO:tensorflow:loss = 285.2644, step = 25219 (45.407 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.22589\n",
      "INFO:tensorflow:loss = 211.87439, step = 25319 (44.926 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20342\n",
      "INFO:tensorflow:loss = 243.43494, step = 25419 (45.384 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 25461 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 268.9229.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-25461\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:14<00:00, 352.35it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:49<00:00, 45.60it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4842258354938339\n",
      "[test] Raw Hits@1: 33.72\n",
      "[test] Raw Hits@3: 57.96\n",
      "[test] Raw Hits@5: 68.12\n",
      "[test] Raw Hits@10: 76.64\n",
      "[test] Filtered MRR: 0.6907829949938759\n",
      "[test] Filtered Hits@1: 54.559999999999995\n",
      "[test] Filtered Hits@3: 82.52000000000001\n",
      "[test] Filtered Hits@5: 85.96000000000001\n",
      "[test] Filtered Hits@10: 88.52\n",
      "\n",
      "EPOCH 28\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-25461\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 25462 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 210.11597, step = 25462\n",
      "INFO:tensorflow:global_step/sec: 2.28963\n",
      "INFO:tensorflow:loss = 237.19478, step = 25562 (43.677 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.45969\n",
      "INFO:tensorflow:loss = 210.95105, step = 25662 (40.655 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.21464\n",
      "INFO:tensorflow:loss = 236.81795, step = 25762 (45.154 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.17246\n",
      "INFO:tensorflow:loss = 175.66231, step = 25862 (46.031 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26817\n",
      "INFO:tensorflow:loss = 241.71771, step = 25962 (44.088 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.50821\n",
      "INFO:tensorflow:loss = 231.53883, step = 26062 (39.869 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.45483\n",
      "INFO:tensorflow:loss = 227.89703, step = 26162 (40.737 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32412\n",
      "INFO:tensorflow:loss = 236.5758, step = 26262 (43.026 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.1512\n",
      "INFO:tensorflow:loss = 259.1307, step = 26362 (46.486 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 26404 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 212.15808.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-26404\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:14<00:00, 352.28it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:52<00:00, 44.39it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4866539642837297\n",
      "[test] Raw Hits@1: 33.839999999999996\n",
      "[test] Raw Hits@3: 58.3\n",
      "[test] Raw Hits@5: 68.56\n",
      "[test] Raw Hits@10: 77.24\n",
      "[test] Filtered MRR: 0.6951836786751612\n",
      "[test] Filtered Hits@1: 54.67999999999999\n",
      "[test] Filtered Hits@3: 83.32000000000001\n",
      "[test] Filtered Hits@5: 86.7\n",
      "[test] Filtered Hits@10: 89.16\n",
      "\n",
      "EPOCH 29\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-26404\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 26405 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 223.96353, step = 26405\n",
      "INFO:tensorflow:global_step/sec: 2.26034\n",
      "INFO:tensorflow:loss = 186.63744, step = 26505 (44.242 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.45938\n",
      "INFO:tensorflow:loss = 182.75815, step = 26605 (40.661 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.39179\n",
      "INFO:tensorflow:loss = 232.62639, step = 26705 (41.811 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32596\n",
      "INFO:tensorflow:loss = 249.5151, step = 26805 (42.992 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.42421\n",
      "INFO:tensorflow:loss = 313.06625, step = 26905 (41.251 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.39795\n",
      "INFO:tensorflow:loss = 248.86252, step = 27005 (41.702 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26632\n",
      "INFO:tensorflow:loss = 222.15988, step = 27105 (44.125 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.38679\n",
      "INFO:tensorflow:loss = 202.38165, step = 27205 (41.897 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32346\n",
      "INFO:tensorflow:loss = 306.74423, step = 27305 (43.040 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 27347 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 209.97629.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-27347\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 362.45it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:49<00:00, 45.70it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4872717631167406\n",
      "[test] Raw Hits@1: 33.7\n",
      "[test] Raw Hits@3: 58.46\n",
      "[test] Raw Hits@5: 68.92\n",
      "[test] Raw Hits@10: 77.48\n",
      "[test] Filtered MRR: 0.6982598506047275\n",
      "[test] Filtered Hits@1: 54.98\n",
      "[test] Filtered Hits@3: 83.58\n",
      "[test] Filtered Hits@5: 87.02\n",
      "[test] Filtered Hits@10: 89.4\n",
      "\n",
      "EPOCH 30\n",
      "\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:\n",
      "[<tf.Variable 'e_embed:0' shape=(40943, 200) dtype=float32_ref>,\n",
      " <tf.Variable 'p_embed:0' shape=(18, 200) dtype=float32_ref>]\n",
      "INFO:tensorflow:params: 8192200\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Create CheckpointSaverHook.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-27347\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n",
      "INFO:tensorflow:Saving checkpoints for 27348 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:loss = 404.25214, step = 27348\n",
      "INFO:tensorflow:global_step/sec: 2.38838\n",
      "INFO:tensorflow:loss = 228.36113, step = 27448 (41.871 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.23761\n",
      "INFO:tensorflow:loss = 147.49889, step = 27548 (44.690 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32672\n",
      "INFO:tensorflow:loss = 215.48106, step = 27648 (42.979 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.27568\n",
      "INFO:tensorflow:loss = 241.2984, step = 27748 (43.943 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.20021\n",
      "INFO:tensorflow:loss = 211.55968, step = 27848 (45.450 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.15487\n",
      "INFO:tensorflow:loss = 198.1694, step = 27948 (46.407 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.26219\n",
      "INFO:tensorflow:loss = 204.03197, step = 28048 (44.205 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.32996\n",
      "INFO:tensorflow:loss = 258.41284, step = 28148 (42.919 sec)\n",
      "INFO:tensorflow:global_step/sec: 2.24398\n",
      "INFO:tensorflow:loss = 407.45425, step = 28248 (44.563 sec)\n",
      "INFO:tensorflow:Saving checkpoints for 28290 into /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt.\n",
      "INFO:tensorflow:Loss for final step: 245.12814.\n",
      "INFO:tensorflow:Calling model_fn.\n",
      "INFO:tensorflow:Done calling model_fn.\n",
      "INFO:tensorflow:Graph was finalized.\n",
      "INFO:tensorflow:Restoring parameters from /var/folders/sx/fv0r97j96fz8njp14dt5g7940000gn/T/tmp6axh782k/model.ckpt-28290\n",
      "INFO:tensorflow:Running local_init_op.\n",
      "INFO:tensorflow:Done running local_init_op.\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "100%|████████████████████████████| 5000/5000 [00:13<00:00, 357.66it/s]\n",
      "100%|█████████████████████████████| 5000/5000 [01:51<00:00, 44.82it/s]\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[test] Raw MRR: 0.4891431242126948\n",
      "[test] Raw Hits@1: 33.82\n",
      "[test] Raw Hits@3: 58.74\n",
      "[test] Raw Hits@5: 69.0\n",
      "[test] Raw Hits@10: 77.68\n",
      "[test] Filtered MRR: 0.6980388435892407\n",
      "[test] Filtered Hits@1: 54.66\n",
      "[test] Filtered Hits@3: 83.94\n",
      "[test] Filtered Hits@5: 87.2\n",
      "[test] Filtered Hits@10: 89.7\n"
     ]
    }
   ],
   "source": [
    "triples_all, triples_tr, triples_va, triples_te = load_triple()\n",
    "e2idx, p2idx, params = build_vocab(triples_all)\n",
    "sp2o = build_multi_label(triples_tr)\n",
    "\n",
    "model = tf.estimator.Estimator(model_fn,\n",
    "                               params = params)\n",
    "\n",
    "for n_epoch in range(Config.n_epochs):\n",
    "    prt_epoch(n_epoch)\n",
    "    model.train(lambda: train_input_fn(triples_tr, e2idx, p2idx, sp2o))\n",
    "    evaluate_rank(model,\n",
    "                  triples_va,\n",
    "                  triples_te,\n",
    "                  triples_all,\n",
    "                  e2idx,\n",
    "                  p2idx,)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": []
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.6.5"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 2
}
